Elastic APM の計測対象関数を拡張する（Python編）
Elastic APM はアプリケーションのパフォーマンスを計測、可視化するツールです。Web リクエスト〜レスポンスだけでなく、Span を利用することで任意の処理を計測できます。Span の処理をアプリケーション内に実装することなく、自由にパフォーマンスを計測する方法をご紹介します。
概要
Elastic APM の概要と、詳細と 2週に続けてブログエントリしました。今までのエントリで Elastic APM の有用性はご理解いただけたのではないでしょうか。
前回のエントリで細かい処理を計測する方法で Span を利用できることをご紹介しました。Span を利用するには Elastic APM が Span としてサポートするライブラリを利用するか、デコレータやwith句によって計測したい処理をくくる方法があります。任意の処理を計測するには後者で実装する必要があります。ただ計測するための処理をアプリケーション内のビジネスロジックに実装することはアプリケーション本来の処理とは関係ないため可読性を落とすことになります。また計測の処理を様々な箇所に実装することで Elastic APM を利用しなくなった時の実装を取り除くのが大変になります。できれば、前者の仕組みを利用しつつ任意の処理を計測したいです。
Elastic APM agent for Python のソースコードを眺めていたところ、サポートするライブラリの仕組みを簡単に拡張できそうだったので試してみました。
試してみた
Elastic APM の自動 Span を拡張するには下記の実装だけで済みます（Django を利用の場合）
- 独自自動 Span（Elastic APM では Instrumentation と呼びます）の実装
- Django の起動処理に独自 Instrumentation の登録
独自 Instrumentation の実装
Instrumentation を実装します。計測対象の関数の定義、関数が呼ばれた時の Span の処理を実装するだけです。もちろん概要でも述べた通り、Web アプリケーションとは関連しない別ファイルに実装します。
app/apm/instrumentation/custom.py
from elasticapm.instrumentation.packages.base import AbstractInstrumentedModule
from elasticapm.traces import capture_span
class UtilInstrumentation(AbstractInstrumentedModule):
instrument_list = [
("app.utils", "capture_method"),
]
def call(self, module, method, wrapped, instance, args, kwargs):
with capture_span('capture_process', 'process_type', leaf=True):
return wrapped(*args, **kwargs)
もっともシンプルな実装です。app.utils.capture_methodという関数の処理開始から終了までを Span として計測します。
クラスはAbstractInstrumentedModuleを継承してください。このクラスにほぼ必要な実装が含まれています。
instrument_list変数に計測対象のパッケージ、関数名の set を配列で登録します。複数登録する場合は set を増やしていけば大丈夫です。
call関数に Span 計測処理を実装します。capture_span の第一、第二引数は Kibana 上に表示されます。このcall関数には計測対象関数に渡った引数も取得できますので処理に応じたメッセージを出すこともできます。後ほどご紹介します。
Django アプリケーションの起動処理に独自 Instrumentation の登録
次に上で作成した Instrumentation を Django 起動時に Elastic APM へ登録します。起動時に一回登録すればよいので、AppConfig に記述するのがいいのではないでしょうか。
from django.apps import AppConfig
from elasticapm.instrumentation.register import register
class AppConfig(AppConfig):
name = 'app'
def ready(self):
super(AppConfig, self).ready()
register('app.apm.instrumentation.custom.CustomInstrumentation')
ハイライト行が追加実装したところとなります。ready 関数で Instrumentation を登録します。Elastic APM の register 関数に作成した Instrumentation のクラスパスを文字列で渡すだけです。
拡張に必要な実装はこれだけです。それでは動作を確認してみましょう。
動作確認
確認の前に計測対象関数と、Django のリクエストを追加します。
計測対象の app.utils.capture_method は引数で渡した秒数 sleep するだけの処理です。
app/utils.py
def capture_method(seconds):
sleep(seconds)
リクエストすると app.utils.capture_method を呼びます。
app/views.py
from .utils import capture_method
def sleep(request):
capture_method(1)
return JsonResponse({'exec': 'sleep'}, status=200)
Django を起動して、Web リクエストを送信して、Kibana を確認します。
記録されていますね。Instarumentation で記述した文字列もそれぞれ表示されています。もうちょっと分かりやすいように文字列を変えてみましょう。
app/apm/instrumentation/custom.py
（略）
def call(self, module, method, wrapped, instance, args, kwargs):
# with capture_span('capture_process', 'process_type', leaf=True):
name = 'sleep {} seconds'.format(args[0])
with capture_span(name, 'sleep', leaf=True):
return wrapped(*args, **kwargs)
計測対象の関数に渡った引数が args で取得できます。何秒の sleep なのかを Kibana 上で表示できるようにします。
app/views.py
from .utils import capture_method
def sleep(request):
capture_method(1)
capture_method(2)
return JsonResponse({'exec': 'sleep'}, status=200)
計測結果の見栄えを良くするためにリクエストの処理で計測対象の関数を二回引数を変えて呼ぶように変更します。
再度、Kibana で確認します。
固定メッセージでは同一の関数が呼ばれて、処理時間に差異があった時になぜ片方だけ遅いのか把握することができません。このように引数を表示することでなぜ片方だけ遅いのか把握することができます。
まとめ
Elastic APM は標準サポートされているライブラリ以外も簡単に拡張することができました。今回は独自処理を計測対象としましたが、もちろんサードパーティライブラリの任意の関数も対象とすることができます。
Elastic APM に限らず、Elastic 社のプロダクトはユーザー独自の拡張方法が設けられているのは本当に嬉しいですね。
